Next | Prev | Up | Top | Contents | Index
Example of prof -gprof -pixie
Here's part of a sample output obtained by using the -gprof and -pixie options. The fields are explained in detail before the output is generated (the format of the output has been adjusted slightly).
call graph profile:
The sum of self and descendents is the major sort
for this listing.
function entries:
index the index of the function in the call graph
listing, as an aid to locating it.
cycles(%cycles)
the total cycles (percentage of total) of the program
accounted for by this function and its descendents.
self(per)
cycles (percent of total) spent in this function itself.
kids(per)
cycles (percent of total) spent in the descendents of
this function on behalf of this function.
called the number of times this function is called (other
than recursive calls).
self the number of times this function calls itself recursively.
name the name of the function, with an indication of
its membership in a cycle, if any.
index the index of the function in the call graph
listing, as an aid to locating it.
parent listings:
self*
cycles of this function's self time which is due to calls from
this parent.
kids*
cycles of this function's descendent time which is due to
calls from this parent.
called** the number of times this function is called by this parent.
This is the numerator of the fraction which divides up the
function's time to its parents.
total* the number of times this function was called by all of its parents.
This is the denominator of the propagation fraction.
parents the name of this parent, with an indication of the
parent's membership in a cycle, if any.
index the index of this parent in the call graph
listing, as an aid in locating it.
children listings:
self*
cycles of this child's self time
which is due to being called by this function.
kids*
cycles of this child's descendent's time which is due to
being called by this function.
called** the number of times this child is called by this function. This
is the numerator of the propagation fraction for this child.
total* the number of times this child is called by all functions.
This is the denominator of the propagation fraction.
children the name of this child, and an indication of its
membership in a cycle, if any.
index the index of this child in the call graph listing,
as an aid to locating it.
* these fields are omitted for parents (or children) in
the same cycle as the function. If the function (or child)
is a member of a cycle, the propagated times and propagation
denominator represent the self time and descendent time of the
cycle as a whole.
** static-only parents and children are indicated
by a call count of 0.
cycle listings:
the cycle as a whole is listed with the same
fields as a function entry. Below it are listed
the members of the cycle, and their contributions
to the time and call counts of the cycle.
All times are in milliseconds.
-----------------------------------------------------------------------------
self kids called/total parents
index cycles(%) self(per) kids(per) called+self name index
self kids called/total children
[1] 7825(99.47%) 36( 0.46%) 7789(99.54%) 0 __start [1]
33 7753 1/1 main [2]
3 0 1/1 __readenv_sigfpe [76]
------------------------------------------------------------------------------
33 7753 1/1 __start [1]
[2] 7786(98.97%) 33( 0.42%) 7753(99.58%) 1 main [2]
18 4559 1/1 _MAIN [3]
183 2258 1/1 f_exit [8]
115 384 5/5 signal [25]
19 217 1/1 exit [33]
------------------------------------------------------------------------------
18 4559 1/1 main [2]
[3] 4577(58.18%) 18( 0.39%) 4559(99.61%) 1 _MAIN [3]
9 4082 1/1 s_wsle64 [4]
9 318 1/1 do_Lio64 [28]
8 133 1/1 e_wsle [43]
------------------------------------------------------------------------------
9 4082 1/1 _MAIN [3]
[4] 4091(52.00%) 9( 0.22%) 4082(99.78%) 1 s_wsle64 [4]
22 4060 1/1 s_wsle_com [5]
------------------------------------------------------------------------------
22 4060 1/1 s_wsle64 [4]
[5] 4082(51.89%) 22( 0.54%) 4060(99.46%) 1 s_wsle_com [5]
28 2016 1/1 c_le [10]
201 1815 1/2 f_init [7]
------------------------------------------------------------------------------
[6] 4033(51.26%) 402( 9.97%) 3631(90.03%) 2+8 <cycle 1 as a whole> [6]
142( 0.02) 3147( 0.42) 5 f_init <cycle 1> [7]
260( 0.03) 484( 0.06) 5 map_luno <cycle 1> [21]
------------------------------------------------------------------------------
4 map_luno <cycle 1> [21]
201 1815 1/2 s_wsle_com [5]
[7] 3289(41.81%) 142( 4.32%) 3147(95.68%) 5 f_init <cycle 1> [7]
15 1896 1/1 init_test_and_set [13]
42 930 1/2 _calloc [12]
51 114 3/3 f77canseek [40]
45 27 3/7 _isatty [39]
15 0 5/5 _getpid [63]
12 0 4/9 _mips2_test_and_set [59]
4 map_luno <cycle 1> [21]
------------------------------------------------------------------------------
183 2258 1/1 main [2]
[8] 2441(31.03%) 183( 7.50%) 2258(92.50%) 1 f_exit [8]
288 1967 32/32 f_clos [9]
3 0 1/1 __checktraps [79]
------------------------------------------------------------------------------
....
Next | Prev | Up | Top | Contents | Index